11-19 20:41:17 D/ModuleListener: ModuleListener.testStarted(com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testHeavyDeviceUsage) on SKBFXYZO0C1V
11-19 20:41:17 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:17 D/DeviceHostUtils: apiLevel: 31
11-19 20:41:17 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:17 D/DeviceHostUtils: apiLevel: 31
11-19 20:41:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:41:18 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
11-19 20:41:18 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
11-19 20:41:18 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:18 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:19 D/RunUtil: Running command null without timeout.
11-19 20:41:19 D/AppRunnerUtils: Checking service: com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
11-19 20:41:19 D/AppRunnerUtils: Running the following command: dumpsys activity service com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
11-19 20:41:19 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, dumpsys, activity, service, com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService] with timeout: 2m 0s
11-19 20:41:19 I/AppRunnerUtils: Service PID = 29625
11-19 20:41:19 I/AssistantTestUtils: Waiting for assistant to be ready...
11-19 20:41:19 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
11-19 20:41:19 D/AssistantTestUtils: Launching Assistant intent
11-19 20:41:19 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
11-19 20:41:19 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
11-19 20:41:19 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
11-19 20:41:19 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:41:19 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:41:19 I/DeviceStateMonitor: Waiting 359922 ms for device SKBFXYZO0C1V package manager
11-19 20:41:19 I/NativeDeviceStateMonitor: Waiting 359800 ms for device SKBFXYZO0C1V external store
11-19 20:41:22 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:41:23 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
11-19 20:41:23 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
11-19 20:41:23 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
11-19 20:41:23 D/AssistantTestUtils: Assistant successfully launched: true
11-19 20:41:23 D/RunUtil: Running command [logcat -d | grep -E 'AssistantWrapper(Impl)?: Assistant is now running.'] without timeout.
11-19 20:41:23 I/AssistantTestUtils: Assistant ready: true
11-19 20:41:23 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
11-19 20:41:23 D/AssistantTestUtils: Launching Assistant intent
11-19 20:41:23 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
11-19 20:41:23 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
11-19 20:41:23 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
11-19 20:41:23 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:41:23 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:41:23 I/DeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V package manager
11-19 20:41:23 I/NativeDeviceStateMonitor: Waiting 359779 ms for device SKBFXYZO0C1V external store
11-19 20:41:25 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:41:26 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
11-19 20:41:26 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
11-19 20:41:26 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
11-19 20:41:26 D/AssistantTestUtils: Assistant successfully launched: true
11-19 20:41:26 D/RunUtil: Running command [check if metrics file pattern is present] without timeout.
11-19 20:41:26 I/AssistantTestUtils: Checking if file pattern is present: /storage/emulated/0/Download/katniss-primes*
11-19 20:41:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
11-19 20:41:26 D/AssistantTestUtils: Supplier "check if metrics file pattern is present" returned: true
11-19 20:41:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
11-19 20:41:26 D/AssistantTestUtils: Session-based metrics File: /storage/emulated/0/Download/katniss-primes-2024-11-19T03_41_25.174.txt
11-19 20:41:26 D/NativeDevice: Using 'ls' to check doesFileExist(/storage/emulated/0/Download/katniss-primes-2024-11-19T03_41_25.174.txt)
11-19 20:41:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:26 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_10622679392175239106.txt'] without timeout.
11-19 20:41:26 D/TvtsBaseAssistantTest: Metrics location: /storage/emulated/0/Download/katniss-primes-2024-11-19T03_41_25.174.txt
11-19 20:41:26 D/TvtsBaseAssistantTest: Option enabling successful!
11-19 20:41:26 I/TvtsBaseAssistantTest: Test: HeavyDeviceUsageTest
11-19 20:41:26 I/MeasurementPrinter: search_to_query_latency	Measurement Status	query_to_result_latency	Measurement Status	query_to_result_no_server_latency	Measurement Status
11-19 20:41:26 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:41:26 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:41:26 I/DeviceStateMonitor: Waiting 359932 ms for device SKBFXYZO0C1V package manager
11-19 20:41:26 I/NativeDeviceStateMonitor: Waiting 359865 ms for device SKBFXYZO0C1V external store
11-19 20:41:28 D/RunUtil: Running command null without timeout.
11-19 20:41:28 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:29 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:41:29 D/RunUtil: Running command null without timeout.
11-19 20:41:29 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:41:29 I/KeyCodeUtils: Sending keyevent KEYCODE_HOME - intValue: 3
11-19 20:41:29 D/AppRunnerUtils: [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:41:29 D/RunUtil: operation failed, waiting for 500 ms
11-19 20:41:29 D/RunUtil: Running command null without timeout.
11-19 20:41:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:30 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:41:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:41:30 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:30 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_17462917751338592905.txt'] without timeout.
11-19 20:41:30 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:41:30 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:41:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:41:31 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:42:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:42:55 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:42:55 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 29.000000
11-19 20:42:55 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 49.000000
11-19 20:42:55 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 984.000000
11-19 20:42:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2908.000000
11-19 20:42:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 540.000000
11-19 20:42:55 D/ProtoMeasurementBase: performer_open: size = 1, sum: 33.000000
11-19 20:42:55 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2974.000000
11-19 20:42:55 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 50.000000
11-19 20:42:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 181.000000
11-19 20:42:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
11-19 20:42:55 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 189.000000
11-19 20:42:55 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:42:55 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:42:55 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:42:55 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 29.000000
11-19 20:42:55 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 49.000000
11-19 20:42:55 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 984.000000
11-19 20:42:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2908.000000
11-19 20:42:55 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:42:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 540.000000
11-19 20:42:55 D/ProtoMeasurementBase: performer_open: size = 1, sum: 33.000000
11-19 20:42:55 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2974.000000
11-19 20:42:55 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 50.000000
11-19 20:42:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 181.000000
11-19 20:42:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
11-19 20:42:55 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 189.000000
11-19 20:42:55 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:42:55 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:42:55 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:42:55 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:42:55 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 29.000000
11-19 20:42:55 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 49.000000
11-19 20:42:55 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 984.000000
11-19 20:42:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2908.000000
11-19 20:42:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 540.000000
11-19 20:42:55 D/ProtoMeasurementBase: performer_open: size = 1, sum: 33.000000
11-19 20:42:55 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2974.000000
11-19 20:42:55 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 50.000000
11-19 20:42:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 181.000000
11-19 20:42:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
11-19 20:42:55 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 189.000000
11-19 20:42:55 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:42:55 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:42:55 I/MeasurementPrinter:                   189.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:42:55 E/TvtsBaseAssistantTest: Run 1/20 encountered exception. See logs for details
11-19 20:42:55 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.442
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:42:55 D/RunUtil: Running command null without timeout.
11-19 20:42:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:55 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:42:55 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:42:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:56 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:42:56 D/RunUtil: Running command null without timeout.
11-19 20:42:56 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:42:56 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:42:56 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:42:56 D/RunUtil: Running command null without timeout.
11-19 20:42:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:56 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:42:56 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:42:56 I/DeviceStateMonitor: Waiting 359959 ms for device SKBFXYZO0C1V package manager
11-19 20:42:57 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYZO0C1V external store
11-19 20:42:58 D/RunUtil: Running command null without timeout.
11-19 20:42:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:42:59 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:42:59 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:42:59 D/RunUtil: Running command null without timeout.
11-19 20:42:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:42:59 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:42:59 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:42:59 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:42:59 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_10755936078288189847.txt'] without timeout.
11-19 20:43:00 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:43:00 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:43:00 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:43:00 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:44:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:44:24 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:44:24 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 29.000000
11-19 20:44:24 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 46.000000
11-19 20:44:24 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 916.000000
11-19 20:44:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2707.000000
11-19 20:44:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 383.000000
11-19 20:44:24 D/ProtoMeasurementBase: performer_open: size = 1, sum: 32.000000
11-19 20:44:24 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2766.000000
11-19 20:44:24 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 47.000000
11-19 20:44:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 83.000000
11-19 20:44:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 18.000000
11-19 20:44:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 131.000000
11-19 20:44:24 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:44:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:44:24 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:44:24 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 29.000000
11-19 20:44:24 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 46.000000
11-19 20:44:24 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 916.000000
11-19 20:44:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2707.000000
11-19 20:44:24 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:44:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 383.000000
11-19 20:44:24 D/ProtoMeasurementBase: performer_open: size = 1, sum: 32.000000
11-19 20:44:24 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2766.000000
11-19 20:44:24 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 47.000000
11-19 20:44:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 83.000000
11-19 20:44:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 18.000000
11-19 20:44:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 131.000000
11-19 20:44:24 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:44:24 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:44:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:44:24 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:44:24 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 29.000000
11-19 20:44:24 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 46.000000
11-19 20:44:24 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 916.000000
11-19 20:44:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2707.000000
11-19 20:44:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 383.000000
11-19 20:44:24 D/ProtoMeasurementBase: performer_open: size = 1, sum: 32.000000
11-19 20:44:24 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2766.000000
11-19 20:44:24 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 47.000000
11-19 20:44:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 83.000000
11-19 20:44:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 18.000000
11-19 20:44:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 131.000000
11-19 20:44:24 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:44:24 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:44:24 I/MeasurementPrinter:                   131.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:44:24 E/TvtsBaseAssistantTest: Run 2/20 encountered exception. See logs for details
11-19 20:44:24 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.492
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:44:24 D/RunUtil: Running command null without timeout.
11-19 20:44:24 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:44:25 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:44:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:44:25 D/RunUtil: Running command null without timeout.
11-19 20:44:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:44:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:44:25 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:44:25 D/RunUtil: Running command null without timeout.
11-19 20:44:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:26 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:44:26 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:44:26 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:44:26 I/NativeDeviceStateMonitor: Waiting 359899 ms for device SKBFXYZO0C1V external store
11-19 20:44:28 D/RunUtil: Running command null without timeout.
11-19 20:44:28 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:44:28 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:44:28 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:44:28 D/RunUtil: Running command null without timeout.
11-19 20:44:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:44:28 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:44:28 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:44:28 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:44:29 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_12743922282278400885.txt'] without timeout.
11-19 20:44:29 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:44:29 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:44:29 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:44:29 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:45:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:45:53 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:45:53 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 14.000000
11-19 20:45:53 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 27.000000
11-19 20:45:53 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 816.000000
11-19 20:45:53 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2654.000000
11-19 20:45:53 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 715.000000
11-19 20:45:53 D/ProtoMeasurementBase: performer_open: size = 1, sum: 24.000000
11-19 20:45:53 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2696.000000
11-19 20:45:53 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 29.000000
11-19 20:45:53 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 384.000000
11-19 20:45:53 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
11-19 20:45:53 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 173.000000
11-19 20:45:53 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:45:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:45:53 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:45:53 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 14.000000
11-19 20:45:53 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 27.000000
11-19 20:45:53 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 816.000000
11-19 20:45:53 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2654.000000
11-19 20:45:53 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:45:53 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 715.000000
11-19 20:45:53 D/ProtoMeasurementBase: performer_open: size = 1, sum: 24.000000
11-19 20:45:53 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2696.000000
11-19 20:45:53 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 29.000000
11-19 20:45:53 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 384.000000
11-19 20:45:53 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
11-19 20:45:53 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 173.000000
11-19 20:45:53 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:45:53 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:45:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:45:53 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:45:53 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 14.000000
11-19 20:45:53 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 27.000000
11-19 20:45:53 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 816.000000
11-19 20:45:53 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2654.000000
11-19 20:45:53 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 715.000000
11-19 20:45:53 D/ProtoMeasurementBase: performer_open: size = 1, sum: 24.000000
11-19 20:45:53 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2696.000000
11-19 20:45:53 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 29.000000
11-19 20:45:53 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 384.000000
11-19 20:45:53 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
11-19 20:45:53 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 173.000000
11-19 20:45:53 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:45:53 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:45:53 I/MeasurementPrinter:                   173.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:45:53 E/TvtsBaseAssistantTest: Run 3/20 encountered exception. See logs for details
11-19 20:45:53 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.554
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:45:53 D/RunUtil: Running command null without timeout.
11-19 20:45:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:45:54 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:45:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:45:54 D/RunUtil: Running command null without timeout.
11-19 20:45:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:45:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:45:55 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:45:55 D/RunUtil: Running command null without timeout.
11-19 20:45:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:55 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:45:55 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:45:55 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:45:55 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:45:57 D/RunUtil: Running command null without timeout.
11-19 20:45:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:45:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:45:57 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:45:57 D/RunUtil: Running command null without timeout.
11-19 20:45:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:45:58 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:45:58 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:45:58 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:45:58 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_15383470021674368181.txt'] without timeout.
11-19 20:45:58 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:45:58 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:45:58 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:45:58 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:47:22 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:47:22 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:47:22 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 25.000000
11-19 20:47:22 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 31.000000
11-19 20:47:22 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1080.000000
11-19 20:47:22 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2619.000000
11-19 20:47:22 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 695.000000
11-19 20:47:22 D/ProtoMeasurementBase: performer_open: size = 1, sum: 23.000000
11-19 20:47:22 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2666.000000
11-19 20:47:22 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 32.000000
11-19 20:47:22 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 363.000000
11-19 20:47:22 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
11-19 20:47:22 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 161.000000
11-19 20:47:22 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:47:22 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:47:22 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:47:22 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 25.000000
11-19 20:47:22 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 31.000000
11-19 20:47:22 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1080.000000
11-19 20:47:22 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2619.000000
11-19 20:47:22 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:47:22 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 695.000000
11-19 20:47:22 D/ProtoMeasurementBase: performer_open: size = 1, sum: 23.000000
11-19 20:47:22 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2666.000000
11-19 20:47:22 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 32.000000
11-19 20:47:22 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 363.000000
11-19 20:47:22 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
11-19 20:47:22 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 161.000000
11-19 20:47:22 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:47:22 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:47:22 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:47:22 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:47:22 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 25.000000
11-19 20:47:22 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 31.000000
11-19 20:47:22 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1080.000000
11-19 20:47:22 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2619.000000
11-19 20:47:22 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 695.000000
11-19 20:47:22 D/ProtoMeasurementBase: performer_open: size = 1, sum: 23.000000
11-19 20:47:22 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2666.000000
11-19 20:47:22 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 32.000000
11-19 20:47:22 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 363.000000
11-19 20:47:22 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
11-19 20:47:22 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 161.000000
11-19 20:47:22 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:47:22 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:47:22 I/MeasurementPrinter:                   161.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:47:22 E/TvtsBaseAssistantTest: Run 4/20 encountered exception. See logs for details
11-19 20:47:22 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.385
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:47:22 D/RunUtil: Running command null without timeout.
11-19 20:47:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:23 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:47:23 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:47:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:23 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:47:23 D/RunUtil: Running command null without timeout.
11-19 20:47:24 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:47:24 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:47:24 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:47:24 D/RunUtil: Running command null without timeout.
11-19 20:47:24 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:24 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:24 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:47:24 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:47:24 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:47:24 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:47:26 D/RunUtil: Running command null without timeout.
11-19 20:47:26 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:47:26 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:47:26 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:47:26 D/RunUtil: Running command null without timeout.
11-19 20:47:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:47:27 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:47:27 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:47:27 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:47:27 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_5576733020163645078.txt'] without timeout.
11-19 20:47:27 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:47:27 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:47:27 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:47:27 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:48:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:48:51 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:48:51 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 21.000000
11-19 20:48:51 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 27.000000
11-19 20:48:51 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1005.000000
11-19 20:48:51 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 705.000000
11-19 20:48:51 D/ProtoMeasurementBase: performer_open: size = 1, sum: 18.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:48:51 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 377.000000
11-19 20:48:51 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
11-19 20:48:51 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 120.000000
11-19 20:48:51 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2903.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:48:51 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2945.000000
11-19 20:48:51 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 27.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 86.000000
11-19 20:48:51 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 157.000000
11-19 20:48:51 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:48:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:48:51 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:48:51 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 21.000000
11-19 20:48:51 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 27.000000
11-19 20:48:51 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1005.000000
11-19 20:48:51 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 705.000000
11-19 20:48:51 D/ProtoMeasurementBase: performer_open: size = 1, sum: 18.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:48:51 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 377.000000
11-19 20:48:51 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
11-19 20:48:51 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 120.000000
11-19 20:48:51 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2903.000000
11-19 20:48:51 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:48:51 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2945.000000
11-19 20:48:51 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 27.000000
11-19 20:48:51 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 86.000000
11-19 20:48:51 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 157.000000
11-19 20:48:51 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:48:51 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:48:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:48:52 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:48:52 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 21.000000
11-19 20:48:52 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 27.000000
11-19 20:48:52 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1005.000000
11-19 20:48:52 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 705.000000
11-19 20:48:52 D/ProtoMeasurementBase: performer_open: size = 1, sum: 18.000000
11-19 20:48:52 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:48:52 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:48:52 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 377.000000
11-19 20:48:52 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
11-19 20:48:52 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 120.000000
11-19 20:48:52 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2903.000000
11-19 20:48:52 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
11-19 20:48:52 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:48:52 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2945.000000
11-19 20:48:52 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 27.000000
11-19 20:48:52 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 86.000000
11-19 20:48:52 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 157.000000
11-19 20:48:52 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:48:52 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:48:52 I/MeasurementPrinter:                   157.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:48:52 E/TvtsBaseAssistantTest: Run 5/20 encountered exception. See logs for details
11-19 20:48:52 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.621
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:48:52 D/RunUtil: Running command null without timeout.
11-19 20:48:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:52 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:48:52 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:48:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:53 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:48:53 D/RunUtil: Running command null without timeout.
11-19 20:48:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:48:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:48:53 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:48:53 D/RunUtil: Running command null without timeout.
11-19 20:48:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:53 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:48:53 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:48:53 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:48:53 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:48:55 D/RunUtil: Running command null without timeout.
11-19 20:48:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:48:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:48:55 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:48:55 D/RunUtil: Running command null without timeout.
11-19 20:48:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:48:56 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:48:56 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:48:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:48:56 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_8838517637910181388.txt'] without timeout.
11-19 20:48:57 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:48:57 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:48:57 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:48:57 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:50:20 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:50:21 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:50:21 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 37.000000
11-19 20:50:21 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 20:50:21 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 973.000000
11-19 20:50:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 735.000000
11-19 20:50:21 D/ProtoMeasurementBase: performer_open: size = 1, sum: 30.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
11-19 20:50:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 479.000000
11-19 20:50:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 53.000000
11-19 20:50:21 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 147.000000
11-19 20:50:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2912.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 50.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:50:21 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2982.000000
11-19 20:50:21 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 38.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 88.000000
11-19 20:50:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 182.000000
11-19 20:50:21 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:50:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:50:21 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:50:21 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 37.000000
11-19 20:50:21 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 20:50:21 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 973.000000
11-19 20:50:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 735.000000
11-19 20:50:21 D/ProtoMeasurementBase: performer_open: size = 1, sum: 30.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
11-19 20:50:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 479.000000
11-19 20:50:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 53.000000
11-19 20:50:21 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 147.000000
11-19 20:50:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2912.000000
11-19 20:50:21 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 50.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:50:21 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2982.000000
11-19 20:50:21 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 38.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 88.000000
11-19 20:50:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 182.000000
11-19 20:50:21 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:50:21 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:50:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:50:21 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:50:21 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 37.000000
11-19 20:50:21 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 20:50:21 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 973.000000
11-19 20:50:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 735.000000
11-19 20:50:21 D/ProtoMeasurementBase: performer_open: size = 1, sum: 30.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
11-19 20:50:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 479.000000
11-19 20:50:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 53.000000
11-19 20:50:21 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 147.000000
11-19 20:50:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2912.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 50.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:50:21 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2982.000000
11-19 20:50:21 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 38.000000
11-19 20:50:21 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 88.000000
11-19 20:50:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 182.000000
11-19 20:50:21 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:50:21 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:50:21 I/MeasurementPrinter:                   182.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:50:21 E/TvtsBaseAssistantTest: Run 6/20 encountered exception. See logs for details
11-19 20:50:21 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.564
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:50:21 D/RunUtil: Running command null without timeout.
11-19 20:50:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:22 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:50:22 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:50:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:22 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:50:22 D/RunUtil: Running command null without timeout.
11-19 20:50:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:50:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:50:22 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:50:22 D/RunUtil: Running command null without timeout.
11-19 20:50:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:23 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:50:23 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:50:23 I/DeviceStateMonitor: Waiting 359959 ms for device SKBFXYZO0C1V package manager
11-19 20:50:23 I/NativeDeviceStateMonitor: Waiting 359872 ms for device SKBFXYZO0C1V external store
11-19 20:50:25 D/RunUtil: Running command null without timeout.
11-19 20:50:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:50:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:50:25 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:50:25 D/RunUtil: Running command null without timeout.
11-19 20:50:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:50:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:50:25 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:50:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:50:26 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_12729754248804630422.txt'] without timeout.
11-19 20:50:26 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:50:26 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:50:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:50:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:51:50 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:51:50 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:51:50 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 34.000000
11-19 20:51:50 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 31.000000
11-19 20:51:50 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 989.000000
11-19 20:51:50 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 642.000000
11-19 20:51:50 D/ProtoMeasurementBase: performer_open: size = 1, sum: 21.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:51:50 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 305.000000
11-19 20:51:50 D/ProtoMeasurementBase: IDLE_AFTER_UI_DISMISSED: size = 1, sum: 0.000000
11-19 20:51:50 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 47.000000
11-19 20:51:50 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 145.000000
11-19 20:51:50 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2876.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 44.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:51:50 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2932.000000
11-19 20:51:50 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 33.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 94.000000
11-19 20:51:50 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 168.000000
11-19 20:51:50 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:51:50 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:51:50 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:51:50 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 34.000000
11-19 20:51:50 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 31.000000
11-19 20:51:50 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 989.000000
11-19 20:51:50 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 642.000000
11-19 20:51:50 D/ProtoMeasurementBase: performer_open: size = 1, sum: 21.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:51:50 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 305.000000
11-19 20:51:50 D/ProtoMeasurementBase: IDLE_AFTER_UI_DISMISSED: size = 1, sum: 0.000000
11-19 20:51:50 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 47.000000
11-19 20:51:50 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 145.000000
11-19 20:51:50 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2876.000000
11-19 20:51:50 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 44.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:51:50 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2932.000000
11-19 20:51:50 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 33.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 94.000000
11-19 20:51:50 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 168.000000
11-19 20:51:50 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:51:50 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:51:50 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:51:50 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:51:50 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 34.000000
11-19 20:51:50 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 31.000000
11-19 20:51:50 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 989.000000
11-19 20:51:50 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 642.000000
11-19 20:51:50 D/ProtoMeasurementBase: performer_open: size = 1, sum: 21.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:51:50 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 305.000000
11-19 20:51:50 D/ProtoMeasurementBase: IDLE_AFTER_UI_DISMISSED: size = 1, sum: 0.000000
11-19 20:51:50 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 47.000000
11-19 20:51:50 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 145.000000
11-19 20:51:50 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2876.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 44.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:51:50 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2932.000000
11-19 20:51:50 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 33.000000
11-19 20:51:50 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 94.000000
11-19 20:51:50 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 168.000000
11-19 20:51:50 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:51:50 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:51:50 I/MeasurementPrinter:                   168.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:51:50 E/TvtsBaseAssistantTest: Run 7/20 encountered exception. See logs for details
11-19 20:51:50 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.516
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:51:50 D/RunUtil: Running command null without timeout.
11-19 20:51:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:51 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:51:51 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:51:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:51 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:51:51 D/RunUtil: Running command null without timeout.
11-19 20:51:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:51:52 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:51:52 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:51:52 D/RunUtil: Running command null without timeout.
11-19 20:51:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:52 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:51:52 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:51:52 I/DeviceStateMonitor: Waiting 359962 ms for device SKBFXYZO0C1V package manager
11-19 20:51:52 I/NativeDeviceStateMonitor: Waiting 359900 ms for device SKBFXYZO0C1V external store
11-19 20:51:54 D/RunUtil: Running command null without timeout.
11-19 20:51:54 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:51:54 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:51:54 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:51:54 D/RunUtil: Running command null without timeout.
11-19 20:51:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:51:55 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:51:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:51:55 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:51:55 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_11547608499066064995.txt'] without timeout.
11-19 20:51:55 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:51:55 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:51:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:51:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:53:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:53:19 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:53:19 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 21.000000
11-19 20:53:19 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 63.000000
11-19 20:53:19 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 912.000000
11-19 20:53:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2931.000000
11-19 20:53:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 570.000000
11-19 20:53:19 D/ProtoMeasurementBase: performer_open: size = 1, sum: 46.000000
11-19 20:53:19 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 3008.000000
11-19 20:53:19 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 64.000000
11-19 20:53:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 270.000000
11-19 20:53:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 27.000000
11-19 20:53:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 149.000000
11-19 20:53:19 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:53:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:53:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:53:19 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 21.000000
11-19 20:53:19 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 63.000000
11-19 20:53:19 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 912.000000
11-19 20:53:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2931.000000
11-19 20:53:19 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:53:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 570.000000
11-19 20:53:19 D/ProtoMeasurementBase: performer_open: size = 1, sum: 46.000000
11-19 20:53:19 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 3008.000000
11-19 20:53:19 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 64.000000
11-19 20:53:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 270.000000
11-19 20:53:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 27.000000
11-19 20:53:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 149.000000
11-19 20:53:19 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:53:19 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:53:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:53:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:53:19 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 21.000000
11-19 20:53:19 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 63.000000
11-19 20:53:19 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 912.000000
11-19 20:53:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2931.000000
11-19 20:53:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 570.000000
11-19 20:53:19 D/ProtoMeasurementBase: performer_open: size = 1, sum: 46.000000
11-19 20:53:19 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 3008.000000
11-19 20:53:19 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 64.000000
11-19 20:53:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 270.000000
11-19 20:53:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 27.000000
11-19 20:53:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 149.000000
11-19 20:53:19 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:53:19 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:53:19 I/MeasurementPrinter:                   149.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:53:19 E/TvtsBaseAssistantTest: Run 8/20 encountered exception. See logs for details
11-19 20:53:19 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.491
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:53:19 D/RunUtil: Running command null without timeout.
11-19 20:53:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:53:20 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:53:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:21 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:53:21 D/RunUtil: Running command null without timeout.
11-19 20:53:21 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:53:21 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:53:21 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:53:21 D/RunUtil: Running command null without timeout.
11-19 20:53:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:21 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:53:21 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:53:21 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:53:21 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:53:23 D/RunUtil: Running command null without timeout.
11-19 20:53:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:53:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:53:23 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:53:23 D/RunUtil: Running command null without timeout.
11-19 20:53:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:53:24 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:53:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:53:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:53:24 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_8547578614025111297.txt'] without timeout.
11-19 20:53:24 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:53:24 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:53:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:53:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:54:48 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:54:48 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:54:48 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 11.000000
11-19 20:54:48 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 36.000000
11-19 20:54:48 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 838.000000
11-19 20:54:48 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 3311.000000
11-19 20:54:48 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 657.000000
11-19 20:54:48 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 20:54:48 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 3363.000000
11-19 20:54:48 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 37.000000
11-19 20:54:48 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 374.000000
11-19 20:54:48 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 37.000000
11-19 20:54:48 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 212.000000
11-19 20:54:48 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:54:48 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:54:48 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:54:48 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 11.000000
11-19 20:54:48 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 36.000000
11-19 20:54:48 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 838.000000
11-19 20:54:48 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 3311.000000
11-19 20:54:48 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:54:48 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 657.000000
11-19 20:54:48 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 20:54:48 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 3363.000000
11-19 20:54:48 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 37.000000
11-19 20:54:48 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 374.000000
11-19 20:54:48 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 37.000000
11-19 20:54:48 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 212.000000
11-19 20:54:48 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:54:48 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:54:48 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:54:49 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:54:49 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 11.000000
11-19 20:54:49 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 36.000000
11-19 20:54:49 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 838.000000
11-19 20:54:49 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 3311.000000
11-19 20:54:49 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 657.000000
11-19 20:54:49 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 20:54:49 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 3363.000000
11-19 20:54:49 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 37.000000
11-19 20:54:49 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 374.000000
11-19 20:54:49 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 37.000000
11-19 20:54:49 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 212.000000
11-19 20:54:49 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:54:49 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:54:49 I/MeasurementPrinter:                   212.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:54:49 E/TvtsBaseAssistantTest: Run 9/20 encountered exception. See logs for details
11-19 20:54:49 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.419
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:54:49 D/RunUtil: Running command null without timeout.
11-19 20:54:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:49 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:54:49 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:54:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:50 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:54:50 D/RunUtil: Running command null without timeout.
11-19 20:54:50 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:54:50 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:54:50 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:54:50 D/RunUtil: Running command null without timeout.
11-19 20:54:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:50 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:54:50 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:54:50 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:54:50 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYZO0C1V external store
11-19 20:54:52 D/RunUtil: Running command null without timeout.
11-19 20:54:52 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:54:52 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:54:52 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:54:52 D/RunUtil: Running command null without timeout.
11-19 20:54:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:54:53 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:54:53 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:54:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:54:53 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_712478391611798799.txt'] without timeout.
11-19 20:54:54 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:54:54 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:54:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:54:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:56:17 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:56:17 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:56:17 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 53.000000
11-19 20:56:17 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 20:56:17 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 979.000000
11-19 20:56:17 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 534.000000
11-19 20:56:17 D/ProtoMeasurementBase: performer_open: size = 1, sum: 21.000000
11-19 20:56:17 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:56:17 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:56:17 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 230.000000
11-19 20:56:17 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 29.000000
11-19 20:56:17 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 124.000000
11-19 20:56:17 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2820.000000
11-19 20:56:17 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 27.000000
11-19 20:56:17 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:56:17 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2869.000000
11-19 20:56:17 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 35.000000
11-19 20:56:17 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 92.000000
11-19 20:56:17 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 158.000000
11-19 20:56:17 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:56:17 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:56:18 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:56:18 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 53.000000
11-19 20:56:18 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 20:56:18 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 979.000000
11-19 20:56:18 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 534.000000
11-19 20:56:18 D/ProtoMeasurementBase: performer_open: size = 1, sum: 21.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:56:18 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 230.000000
11-19 20:56:18 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 29.000000
11-19 20:56:18 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 124.000000
11-19 20:56:18 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2820.000000
11-19 20:56:18 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 27.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:56:18 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2869.000000
11-19 20:56:18 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 35.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 92.000000
11-19 20:56:18 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 158.000000
11-19 20:56:18 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:56:18 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:56:18 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:56:18 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:56:18 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 53.000000
11-19 20:56:18 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 20:56:18 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 979.000000
11-19 20:56:18 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 534.000000
11-19 20:56:18 D/ProtoMeasurementBase: performer_open: size = 1, sum: 21.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:56:18 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 230.000000
11-19 20:56:18 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 29.000000
11-19 20:56:18 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 124.000000
11-19 20:56:18 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2820.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 27.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:56:18 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2869.000000
11-19 20:56:18 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 35.000000
11-19 20:56:18 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 92.000000
11-19 20:56:18 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 158.000000
11-19 20:56:18 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:56:18 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:56:18 I/MeasurementPrinter:                   158.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:56:18 E/TvtsBaseAssistantTest: Run 10/20 encountered exception. See logs for details
11-19 20:56:18 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.426
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:56:18 D/RunUtil: Running command null without timeout.
11-19 20:56:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:18 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:56:18 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:56:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:19 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:56:19 D/RunUtil: Running command null without timeout.
11-19 20:56:19 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:56:19 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:56:19 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:56:19 D/RunUtil: Running command null without timeout.
11-19 20:56:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:19 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:56:19 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:56:19 I/DeviceStateMonitor: Waiting 359933 ms for device SKBFXYZO0C1V package manager
11-19 20:56:20 I/NativeDeviceStateMonitor: Waiting 359866 ms for device SKBFXYZO0C1V external store
11-19 20:56:21 D/RunUtil: Running command null without timeout.
11-19 20:56:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:56:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:56:22 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:56:22 D/RunUtil: Running command null without timeout.
11-19 20:56:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:56:22 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:56:22 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:56:22 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:56:23 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_2611654776692031431.txt'] without timeout.
11-19 20:56:23 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:56:23 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:56:23 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:56:23 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:57:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:57:47 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:57:47 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 30.000000
11-19 20:57:47 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 30.000000
11-19 20:57:47 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 852.000000
11-19 20:57:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 565.000000
11-19 20:57:47 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:57:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 228.000000
11-19 20:57:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 24.000000
11-19 20:57:47 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 144.000000
11-19 20:57:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2839.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
11-19 20:57:47 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2886.000000
11-19 20:57:47 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 32.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 116.000000
11-19 20:57:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 168.000000
11-19 20:57:47 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:57:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:57:47 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:57:47 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 30.000000
11-19 20:57:47 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 30.000000
11-19 20:57:47 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 852.000000
11-19 20:57:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 565.000000
11-19 20:57:47 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:57:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 228.000000
11-19 20:57:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 24.000000
11-19 20:57:47 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 144.000000
11-19 20:57:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2839.000000
11-19 20:57:47 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
11-19 20:57:47 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2886.000000
11-19 20:57:47 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 32.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 116.000000
11-19 20:57:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 168.000000
11-19 20:57:47 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:57:47 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:57:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:57:47 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:57:47 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 30.000000
11-19 20:57:47 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 30.000000
11-19 20:57:47 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 852.000000
11-19 20:57:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 565.000000
11-19 20:57:47 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:57:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 228.000000
11-19 20:57:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 24.000000
11-19 20:57:47 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 144.000000
11-19 20:57:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2839.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
11-19 20:57:47 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2886.000000
11-19 20:57:47 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 32.000000
11-19 20:57:47 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 116.000000
11-19 20:57:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 168.000000
11-19 20:57:47 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:57:47 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:57:47 I/MeasurementPrinter:                   168.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:57:47 E/TvtsBaseAssistantTest: Run 11/20 encountered exception. See logs for details
11-19 20:57:47 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.398
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:57:47 D/RunUtil: Running command null without timeout.
11-19 20:57:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:57:48 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:57:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:57:48 D/RunUtil: Running command null without timeout.
11-19 20:57:48 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:57:49 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:57:49 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:57:49 D/RunUtil: Running command null without timeout.
11-19 20:57:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:49 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:57:49 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:57:49 I/DeviceStateMonitor: Waiting 359962 ms for device SKBFXYZO0C1V package manager
11-19 20:57:49 I/NativeDeviceStateMonitor: Waiting 359895 ms for device SKBFXYZO0C1V external store
11-19 20:57:51 D/RunUtil: Running command null without timeout.
11-19 20:57:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:57:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:57:51 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:57:51 D/RunUtil: Running command null without timeout.
11-19 20:57:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:57:52 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:57:52 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:57:52 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:57:52 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_9171489436906882523.txt'] without timeout.
11-19 20:57:52 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:57:52 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:57:52 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:57:52 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:59:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:59:16 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:59:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 31.000000
11-19 20:59:16 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 20:59:16 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 920.000000
11-19 20:59:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 660.000000
11-19 20:59:16 D/ProtoMeasurementBase: performer_open: size = 1, sum: 22.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 8.000000
11-19 20:59:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 327.000000
11-19 20:59:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
11-19 20:59:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 107.000000
11-19 20:59:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2704.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:59:16 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2756.000000
11-19 20:59:16 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 36.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 76.000000
11-19 20:59:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 138.000000
11-19 20:59:16 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:59:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:59:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:59:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 31.000000
11-19 20:59:16 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 20:59:16 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 920.000000
11-19 20:59:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 660.000000
11-19 20:59:16 D/ProtoMeasurementBase: performer_open: size = 1, sum: 22.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 8.000000
11-19 20:59:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 327.000000
11-19 20:59:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
11-19 20:59:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 107.000000
11-19 20:59:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2704.000000
11-19 20:59:16 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:59:16 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2756.000000
11-19 20:59:16 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 36.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 76.000000
11-19 20:59:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 138.000000
11-19 20:59:16 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:59:16 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 20:59:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:59:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:59:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 31.000000
11-19 20:59:16 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 20:59:16 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 920.000000
11-19 20:59:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 660.000000
11-19 20:59:16 D/ProtoMeasurementBase: performer_open: size = 1, sum: 22.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 8.000000
11-19 20:59:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 327.000000
11-19 20:59:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
11-19 20:59:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 107.000000
11-19 20:59:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2704.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:59:16 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2756.000000
11-19 20:59:16 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 36.000000
11-19 20:59:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 76.000000
11-19 20:59:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 138.000000
11-19 20:59:16 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 20:59:16 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 20:59:16 I/MeasurementPrinter:                   138.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 20:59:16 E/TvtsBaseAssistantTest: Run 12/20 encountered exception. See logs for details
11-19 20:59:16 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.609
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 20:59:16 D/RunUtil: Running command null without timeout.
11-19 20:59:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:59:17 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:59:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:18 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:59:18 D/RunUtil: Running command null without timeout.
11-19 20:59:18 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:59:18 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:59:18 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:59:18 D/RunUtil: Running command null without timeout.
11-19 20:59:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:18 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:59:18 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:59:18 I/DeviceStateMonitor: Waiting 359939 ms for device SKBFXYZO0C1V package manager
11-19 20:59:18 I/NativeDeviceStateMonitor: Waiting 359873 ms for device SKBFXYZO0C1V external store
11-19 20:59:20 D/RunUtil: Running command null without timeout.
11-19 20:59:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:59:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:59:20 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:59:20 D/RunUtil: Running command null without timeout.
11-19 20:59:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:59:21 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:59:21 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:59:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:59:21 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_11007127481895942151.txt'] without timeout.
11-19 20:59:22 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:59:22 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:59:22 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:59:22 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:00:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:00:45 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:00:45 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 17.000000
11-19 21:00:45 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 29.000000
11-19 21:00:45 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 831.000000
11-19 21:00:45 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 704.000000
11-19 21:00:45 D/ProtoMeasurementBase: performer_open: size = 1, sum: 25.000000
11-19 21:00:45 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 21:00:45 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:00:45 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 489.000000
11-19 21:00:45 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 21.000000
11-19 21:00:45 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 123.000000
11-19 21:00:45 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2744.000000
11-19 21:00:45 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 18.000000
11-19 21:00:45 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:00:45 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2800.000000
11-19 21:00:45 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 30.000000
11-19 21:00:45 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 100.000000
11-19 21:00:45 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 150.000000
11-19 21:00:45 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:00:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:00:46 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:00:46 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 17.000000
11-19 21:00:46 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 29.000000
11-19 21:00:46 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 831.000000
11-19 21:00:46 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 704.000000
11-19 21:00:46 D/ProtoMeasurementBase: performer_open: size = 1, sum: 25.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:00:46 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 489.000000
11-19 21:00:46 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 21.000000
11-19 21:00:46 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 123.000000
11-19 21:00:46 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2744.000000
11-19 21:00:46 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 18.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:00:46 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2800.000000
11-19 21:00:46 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 30.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 100.000000
11-19 21:00:46 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 150.000000
11-19 21:00:46 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:00:46 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:00:46 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:00:46 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:00:46 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 17.000000
11-19 21:00:46 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 29.000000
11-19 21:00:46 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 831.000000
11-19 21:00:46 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 704.000000
11-19 21:00:46 D/ProtoMeasurementBase: performer_open: size = 1, sum: 25.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:00:46 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 489.000000
11-19 21:00:46 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 21.000000
11-19 21:00:46 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 123.000000
11-19 21:00:46 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2744.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 18.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:00:46 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2800.000000
11-19 21:00:46 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 30.000000
11-19 21:00:46 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 100.000000
11-19 21:00:46 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 150.000000
11-19 21:00:46 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:00:46 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:00:46 I/MeasurementPrinter:                   150.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:00:46 E/TvtsBaseAssistantTest: Run 13/20 encountered exception. See logs for details
11-19 21:00:46 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.525
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:00:46 D/RunUtil: Running command null without timeout.
11-19 21:00:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:47 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:00:47 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:00:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:47 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:00:47 D/RunUtil: Running command null without timeout.
11-19 21:00:47 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:00:47 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:00:47 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:00:47 D/RunUtil: Running command null without timeout.
11-19 21:00:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:47 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:00:47 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 21:00:47 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 21:00:48 I/NativeDeviceStateMonitor: Waiting 359877 ms for device SKBFXYZO0C1V external store
11-19 21:00:50 D/RunUtil: Running command null without timeout.
11-19 21:00:50 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:00:50 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:00:50 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:00:50 D/RunUtil: Running command null without timeout.
11-19 21:00:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:00:50 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:00:50 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:00:50 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:00:51 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_10929578332855859970.txt'] without timeout.
11-19 21:00:51 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:00:51 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:00:51 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:00:51 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:02:15 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:02:15 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:02:15 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 20.000000
11-19 21:02:15 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 22.000000
11-19 21:02:15 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 870.000000
11-19 21:02:15 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2954.000000
11-19 21:02:15 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 754.000000
11-19 21:02:15 D/ProtoMeasurementBase: performer_open: size = 1, sum: 17.000000
11-19 21:02:15 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2994.000000
11-19 21:02:15 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 23.000000
11-19 21:02:15 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 365.000000
11-19 21:02:15 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:02:15 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 185.000000
11-19 21:02:15 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:02:15 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:02:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:02:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 20.000000
11-19 21:02:16 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 22.000000
11-19 21:02:16 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 870.000000
11-19 21:02:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2954.000000
11-19 21:02:16 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:02:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 754.000000
11-19 21:02:16 D/ProtoMeasurementBase: performer_open: size = 1, sum: 17.000000
11-19 21:02:16 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2994.000000
11-19 21:02:16 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 23.000000
11-19 21:02:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 365.000000
11-19 21:02:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:02:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 185.000000
11-19 21:02:16 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:02:16 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:02:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:02:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:02:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 20.000000
11-19 21:02:16 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 22.000000
11-19 21:02:16 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 870.000000
11-19 21:02:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2954.000000
11-19 21:02:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 754.000000
11-19 21:02:16 D/ProtoMeasurementBase: performer_open: size = 1, sum: 17.000000
11-19 21:02:16 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2994.000000
11-19 21:02:16 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 23.000000
11-19 21:02:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 365.000000
11-19 21:02:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:02:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 185.000000
11-19 21:02:16 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:02:16 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:02:16 I/MeasurementPrinter:                   185.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:02:16 E/TvtsBaseAssistantTest: Run 14/20 encountered exception. See logs for details
11-19 21:02:16 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.764
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:02:16 D/RunUtil: Running command null without timeout.
11-19 21:02:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:16 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:02:16 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:02:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:02:17 D/RunUtil: Running command null without timeout.
11-19 21:02:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:02:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:02:17 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:02:17 D/RunUtil: Running command null without timeout.
11-19 21:02:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:17 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:02:17 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 21:02:17 I/DeviceStateMonitor: Waiting 359958 ms for device SKBFXYZO0C1V package manager
11-19 21:02:18 I/NativeDeviceStateMonitor: Waiting 359896 ms for device SKBFXYZO0C1V external store
11-19 21:02:19 D/RunUtil: Running command null without timeout.
11-19 21:02:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:02:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:02:20 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:02:20 D/RunUtil: Running command null without timeout.
11-19 21:02:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:02:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:02:20 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:02:20 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:02:21 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_8411655734037750687.txt'] without timeout.
11-19 21:02:21 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:02:21 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:02:21 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:02:21 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:03:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:03:45 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:03:45 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 18.000000
11-19 21:03:45 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 26.000000
11-19 21:03:45 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1097.000000
11-19 21:03:45 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2711.000000
11-19 21:03:45 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 671.000000
11-19 21:03:45 D/ProtoMeasurementBase: performer_open: size = 1, sum: 20.000000
11-19 21:03:45 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2754.000000
11-19 21:03:45 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 26.000000
11-19 21:03:45 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 443.000000
11-19 21:03:45 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:03:45 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 143.000000
11-19 21:03:45 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:03:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:03:45 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:03:45 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 18.000000
11-19 21:03:45 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 26.000000
11-19 21:03:45 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1097.000000
11-19 21:03:45 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2711.000000
11-19 21:03:45 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:03:45 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 671.000000
11-19 21:03:45 D/ProtoMeasurementBase: performer_open: size = 1, sum: 20.000000
11-19 21:03:45 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2754.000000
11-19 21:03:45 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 26.000000
11-19 21:03:45 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 443.000000
11-19 21:03:45 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:03:45 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 143.000000
11-19 21:03:45 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:03:45 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:03:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:03:45 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:03:45 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 18.000000
11-19 21:03:45 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 26.000000
11-19 21:03:45 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 1097.000000
11-19 21:03:45 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2711.000000
11-19 21:03:45 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 671.000000
11-19 21:03:45 D/ProtoMeasurementBase: performer_open: size = 1, sum: 20.000000
11-19 21:03:45 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2754.000000
11-19 21:03:45 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 26.000000
11-19 21:03:45 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 443.000000
11-19 21:03:45 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:03:45 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 143.000000
11-19 21:03:45 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:03:45 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:03:45 I/MeasurementPrinter:                   143.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:03:45 E/TvtsBaseAssistantTest: Run 15/20 encountered exception. See logs for details
11-19 21:03:45 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.416
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:03:45 D/RunUtil: Running command null without timeout.
11-19 21:03:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:46 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:03:46 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:03:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:46 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:03:46 D/RunUtil: Running command null without timeout.
11-19 21:03:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:03:47 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:03:47 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:03:47 D/RunUtil: Running command null without timeout.
11-19 21:03:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:47 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:03:47 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 21:03:47 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 21:03:47 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYZO0C1V external store
11-19 21:03:49 D/RunUtil: Running command null without timeout.
11-19 21:03:49 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:03:49 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:03:49 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:03:49 D/RunUtil: Running command null without timeout.
11-19 21:03:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:03:49 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:03:49 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:03:50 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:03:50 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_14676432339351808190.txt'] without timeout.
11-19 21:03:50 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:03:50 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:03:50 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:03:50 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:05:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:05:14 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:05:14 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 22.000000
11-19 21:05:14 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 32.000000
11-19 21:05:14 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 935.000000
11-19 21:05:14 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 658.000000
11-19 21:05:14 D/ProtoMeasurementBase: performer_open: size = 1, sum: 23.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:05:14 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 347.000000
11-19 21:05:14 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:05:14 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 95.000000
11-19 21:05:14 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2945.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 21.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:05:14 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2996.000000
11-19 21:05:14 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 33.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 69.000000
11-19 21:05:14 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 132.000000
11-19 21:05:14 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:05:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:05:14 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:05:14 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 22.000000
11-19 21:05:14 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 32.000000
11-19 21:05:14 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 935.000000
11-19 21:05:14 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 658.000000
11-19 21:05:14 D/ProtoMeasurementBase: performer_open: size = 1, sum: 23.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:05:14 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 347.000000
11-19 21:05:14 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:05:14 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 95.000000
11-19 21:05:14 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2945.000000
11-19 21:05:14 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 21.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:05:14 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2996.000000
11-19 21:05:14 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 33.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 69.000000
11-19 21:05:14 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 132.000000
11-19 21:05:14 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:05:14 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:05:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:05:14 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:05:14 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 22.000000
11-19 21:05:14 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 32.000000
11-19 21:05:14 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 935.000000
11-19 21:05:14 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 658.000000
11-19 21:05:14 D/ProtoMeasurementBase: performer_open: size = 1, sum: 23.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:05:14 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 347.000000
11-19 21:05:14 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 25.000000
11-19 21:05:14 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 95.000000
11-19 21:05:14 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2945.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 21.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:05:14 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2996.000000
11-19 21:05:14 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 33.000000
11-19 21:05:14 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 69.000000
11-19 21:05:14 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 132.000000
11-19 21:05:14 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:05:14 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:05:14 I/MeasurementPrinter:                   132.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:05:14 E/TvtsBaseAssistantTest: Run 16/20 encountered exception. See logs for details
11-19 21:05:14 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.469
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:05:14 D/RunUtil: Running command null without timeout.
11-19 21:05:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:15 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:05:15 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:05:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:16 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:05:16 D/RunUtil: Running command null without timeout.
11-19 21:05:16 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:05:16 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:05:16 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:05:16 D/RunUtil: Running command null without timeout.
11-19 21:05:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:16 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:05:16 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 21:05:16 I/DeviceStateMonitor: Waiting 359961 ms for device SKBFXYZO0C1V package manager
11-19 21:05:16 I/NativeDeviceStateMonitor: Waiting 359899 ms for device SKBFXYZO0C1V external store
11-19 21:05:18 D/RunUtil: Running command null without timeout.
11-19 21:05:18 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:05:18 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:05:18 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:05:18 D/RunUtil: Running command null without timeout.
11-19 21:05:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:05:19 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:05:19 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:05:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:05:19 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_11709809032996591755.txt'] without timeout.
11-19 21:05:19 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:05:19 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:05:19 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:05:19 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:06:43 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:06:43 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:06:43 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 38.000000
11-19 21:06:43 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 39.000000
11-19 21:06:43 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 903.000000
11-19 21:06:43 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 706.000000
11-19 21:06:43 D/ProtoMeasurementBase: performer_open: size = 1, sum: 26.000000
11-19 21:06:43 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
11-19 21:06:43 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:06:43 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 319.000000
11-19 21:06:43 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 30.000000
11-19 21:06:43 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 117.000000
11-19 21:06:43 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2876.000000
11-19 21:06:43 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 26.000000
11-19 21:06:43 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:06:43 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2943.000000
11-19 21:06:43 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 40.000000
11-19 21:06:43 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 84.000000
11-19 21:06:43 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 136.000000
11-19 21:06:43 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:06:43 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:06:44 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:06:44 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 38.000000
11-19 21:06:44 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 39.000000
11-19 21:06:44 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 903.000000
11-19 21:06:44 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 706.000000
11-19 21:06:44 D/ProtoMeasurementBase: performer_open: size = 1, sum: 26.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:06:44 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 319.000000
11-19 21:06:44 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 30.000000
11-19 21:06:44 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 117.000000
11-19 21:06:44 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2876.000000
11-19 21:06:44 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 26.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:06:44 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2943.000000
11-19 21:06:44 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 40.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 84.000000
11-19 21:06:44 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 136.000000
11-19 21:06:44 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:06:44 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:06:44 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:06:44 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:06:44 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 38.000000
11-19 21:06:44 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 39.000000
11-19 21:06:44 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 903.000000
11-19 21:06:44 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 706.000000
11-19 21:06:44 D/ProtoMeasurementBase: performer_open: size = 1, sum: 26.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 21:06:44 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 319.000000
11-19 21:06:44 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 30.000000
11-19 21:06:44 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 117.000000
11-19 21:06:44 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2876.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 26.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:06:44 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2943.000000
11-19 21:06:44 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 40.000000
11-19 21:06:44 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 84.000000
11-19 21:06:44 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 136.000000
11-19 21:06:44 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:06:44 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:06:44 I/MeasurementPrinter:                   136.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:06:44 E/TvtsBaseAssistantTest: Run 17/20 encountered exception. See logs for details
11-19 21:06:44 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.636
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:06:44 D/RunUtil: Running command null without timeout.
11-19 21:06:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:44 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:06:44 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:06:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:45 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:06:45 D/RunUtil: Running command null without timeout.
11-19 21:06:45 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:06:45 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:06:45 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:06:45 D/RunUtil: Running command null without timeout.
11-19 21:06:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:45 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:06:45 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 21:06:45 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 21:06:45 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYZO0C1V external store
11-19 21:06:47 D/RunUtil: Running command null without timeout.
11-19 21:06:47 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:06:48 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:06:48 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:06:48 D/RunUtil: Running command null without timeout.
11-19 21:06:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:06:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:06:48 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:06:48 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:06:48 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_12143474673523635329.txt'] without timeout.
11-19 21:06:49 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:06:49 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:06:49 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:06:49 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:08:12 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:08:13 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:08:13 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 32.000000
11-19 21:08:13 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 21:08:13 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 801.000000
11-19 21:08:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2647.000000
11-19 21:08:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 611.000000
11-19 21:08:13 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 21:08:13 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2705.000000
11-19 21:08:13 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 34.000000
11-19 21:08:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 331.000000
11-19 21:08:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 42.000000
11-19 21:08:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 179.000000
11-19 21:08:13 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:08:13 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:08:13 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:08:13 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 32.000000
11-19 21:08:13 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 21:08:13 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 801.000000
11-19 21:08:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2647.000000
11-19 21:08:13 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:08:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 611.000000
11-19 21:08:13 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 21:08:13 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2705.000000
11-19 21:08:13 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 34.000000
11-19 21:08:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 331.000000
11-19 21:08:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 42.000000
11-19 21:08:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 179.000000
11-19 21:08:13 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:08:13 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:08:13 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:08:13 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:08:13 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 32.000000
11-19 21:08:13 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 33.000000
11-19 21:08:13 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 801.000000
11-19 21:08:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2647.000000
11-19 21:08:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 611.000000
11-19 21:08:13 D/ProtoMeasurementBase: performer_open: size = 1, sum: 27.000000
11-19 21:08:13 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2705.000000
11-19 21:08:13 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 34.000000
11-19 21:08:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 331.000000
11-19 21:08:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 42.000000
11-19 21:08:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 179.000000
11-19 21:08:13 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:08:13 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:08:13 I/MeasurementPrinter:                   179.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:08:13 E/TvtsBaseAssistantTest: Run 18/20 encountered exception. See logs for details
11-19 21:08:13 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.375
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:08:13 D/RunUtil: Running command null without timeout.
11-19 21:08:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:08:14 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:08:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:08:14 D/RunUtil: Running command null without timeout.
11-19 21:08:14 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:08:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:08:15 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:08:15 D/RunUtil: Running command null without timeout.
11-19 21:08:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:15 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:08:15 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 21:08:15 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 21:08:15 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 21:08:17 D/RunUtil: Running command null without timeout.
11-19 21:08:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:08:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:08:17 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:08:17 D/RunUtil: Running command null without timeout.
11-19 21:08:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:08:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:08:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:08:18 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:08:18 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_2888433445738239774.txt'] without timeout.
11-19 21:08:18 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:08:18 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:08:18 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:08:18 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:09:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:09:42 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:09:42 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 30.000000
11-19 21:09:42 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 21:09:42 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 904.000000
11-19 21:09:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2888.000000
11-19 21:09:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 611.000000
11-19 21:09:42 D/ProtoMeasurementBase: performer_open: size = 1, sum: 31.000000
11-19 21:09:42 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2939.000000
11-19 21:09:42 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 37.000000
11-19 21:09:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 272.000000
11-19 21:09:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 39.000000
11-19 21:09:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 161.000000
11-19 21:09:42 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:09:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:09:42 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:09:42 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 30.000000
11-19 21:09:42 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 21:09:42 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 904.000000
11-19 21:09:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2888.000000
11-19 21:09:42 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:09:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 611.000000
11-19 21:09:42 D/ProtoMeasurementBase: performer_open: size = 1, sum: 31.000000
11-19 21:09:42 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2939.000000
11-19 21:09:42 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 37.000000
11-19 21:09:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 272.000000
11-19 21:09:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 39.000000
11-19 21:09:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 161.000000
11-19 21:09:42 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:09:42 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:09:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:09:42 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:09:42 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 30.000000
11-19 21:09:42 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 21:09:42 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 904.000000
11-19 21:09:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2888.000000
11-19 21:09:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 611.000000
11-19 21:09:42 D/ProtoMeasurementBase: performer_open: size = 1, sum: 31.000000
11-19 21:09:42 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2939.000000
11-19 21:09:42 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 37.000000
11-19 21:09:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 272.000000
11-19 21:09:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 39.000000
11-19 21:09:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 161.000000
11-19 21:09:42 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:09:42 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:09:42 I/MeasurementPrinter:                   161.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:09:42 E/TvtsBaseAssistantTest: Run 19/20 encountered exception. See logs for details
11-19 21:09:42 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.335
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:09:42 D/RunUtil: Running command null without timeout.
11-19 21:09:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:43 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:09:43 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:09:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:43 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:09:43 D/RunUtil: Running command null without timeout.
11-19 21:09:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:09:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:09:44 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:09:44 D/RunUtil: Running command null without timeout.
11-19 21:09:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:44 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 21:09:44 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 21:09:44 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 21:09:44 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 21:09:46 D/RunUtil: Running command null without timeout.
11-19 21:09:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:09:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:09:46 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:09:46 D/RunUtil: Running command null without timeout.
11-19 21:09:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:09:47 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:09:47 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 21:09:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:09:47 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_41_25.174_16046286039388083683.txt'] without timeout.
11-19 21:09:47 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 21:09:47 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 21:09:47 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 21:09:47 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.HeavyDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 21:11:11 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:11 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 21:11:11 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 18.000000
11-19 21:11:11 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 21:11:11 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 937.000000
11-19 21:11:11 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 520.000000
11-19 21:11:11 D/ProtoMeasurementBase: performer_open: size = 1, sum: 33.000000
11-19 21:11:11 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 21:11:11 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
11-19 21:11:11 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 331.000000
11-19 21:11:11 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
11-19 21:11:11 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 201.000000
11-19 21:11:11 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2916.000000
11-19 21:11:11 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
11-19 21:11:11 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:11:11 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2971.000000
11-19 21:11:11 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 38.000000
11-19 21:11:11 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 162.000000
11-19 21:11:11 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 231.000000
11-19 21:11:11 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 21:11:11 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:12 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 21:11:12 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 18.000000
11-19 21:11:12 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 21:11:12 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 937.000000
11-19 21:11:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 520.000000
11-19 21:11:12 D/ProtoMeasurementBase: performer_open: size = 1, sum: 33.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
11-19 21:11:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 331.000000
11-19 21:11:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
11-19 21:11:12 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 201.000000
11-19 21:11:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2916.000000
11-19 21:11:12 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:11:12 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2971.000000
11-19 21:11:12 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 38.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 162.000000
11-19 21:11:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 231.000000
11-19 21:11:12 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:11:12 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_latency
11-19 21:11:12 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:12 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 21:11:12 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 18.000000
11-19 21:11:12 D/ProtoMeasurementBase: result_fulfilled_provider_open: size = 1, sum: 37.000000
11-19 21:11:12 D/ProtoMeasurementBase: in_app_interaction_execution: size = 1, sum: 937.000000
11-19 21:11:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 520.000000
11-19 21:11:12 D/ProtoMeasurementBase: performer_open: size = 1, sum: 33.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
11-19 21:11:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 331.000000
11-19 21:11:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
11-19 21:11:12 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 201.000000
11-19 21:11:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2916.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 21:11:12 D/ProtoMeasurementBase: e2e_app_control: size = 1, sum: 2971.000000
11-19 21:11:12 D/ProtoMeasurementBase: e2e_client_app_control: size = 1, sum: 38.000000
11-19 21:11:12 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 162.000000
11-19 21:11:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 231.000000
11-19 21:11:12 E/ProtoMeasurementBase: [FAILURE] Missing latency - result_displayed_text
11-19 21:11:12 E/TvtsBaseAssistantTest: [FAILURE] Assistant Validation failed. Invalidating response value: query_to_result_no_server_latency
11-19 21:11:12 I/MeasurementPrinter:                   231.0	                OK	                   -1.0	    INVALID RESULT	                             -1.0	    INVALID RESULT
11-19 21:11:12 E/TvtsBaseAssistantTest: Run 20/20 encountered exception. See logs for details
11-19 21:11:12 E/TvtsBaseAssistantTest: HeavyDeviceUsageTest failed: 
com.google.android.assistant.tvts.HeavyDeviceUsageTest:
Error in testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest):
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)


Time: 81.678
There was 1 failure:
1) testHiResponse(com.google.android.assistant.tvts.HeavyDeviceUsageTest)
java.lang.AssertionError: Failed to find BySelector [RES='\Qcom.google.android.katniss:id/text_response_content\E'] within 60000
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.assertTrueAndTakeScreenShot(AssistantQueryTestBase.java:363)
	at com.google.android.assistant.tvts.AssistantQueryTestBase.awaitTextResponseContent(AssistantQueryTestBase.java:237)
	at com.google.android.assistant.tvts.HeavyDeviceUsageTest.testHiResponse(HeavyDeviceUsageTest.java:43)

FAILURES!!!
Tests run: 1,  Failures: 1



11-19 21:11:12 D/RunUtil: Running command null without timeout.
11-19 21:11:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:11:12 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:11:12 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:11:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:11:13 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 21:11:13 D/RunUtil: Running command null without timeout.
11-19 21:11:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:11:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 21:11:13 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 21:11:13 D/RunUtil: Running command null without timeout.
11-19 21:11:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:11:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 21:11:14 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
11-19 21:11:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
11-19 21:11:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 21:11:15 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, getprop, ro.config.low_ram] with timeout: 45s
11-19 21:11:15 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, pm, list, features] with timeout: 2m 0s
11-19 21:11:15 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYZO0C1V
11-19 21:11:15 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, getprop, ro.config.low_ram] with timeout: 45s
11-19 21:11:15 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, pm, list, features] with timeout: 2m 0s
11-19 21:11:15 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYZO0C1V
11-19 21:11:15 I/BasicAggregationTypeBase: Checking if collection is initialized with data
11-19 21:11:15 I/BasicAggregationTypeBase: Checking if collection is initialized with data
11-19 21:11:15 D/PrettyTestEventLogger: 
==================== com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testHeavyDeviceUsage ENDED: Tue Nov 19 21:11:15 KST 2024 ====================
